dgit.raspbian.org Git - git-annex.git/blob

   1 [[!comment format=mdwn
   2  username="joey"
   3  subject="""comment 2"""
   4  date="2022-07-13T19:53:44Z"
   5  content="""
   6 Just reproduced this. In my big repo, I had commit
   7 eab6ac8b34be1d7c36df2a2f41a9414cf5908041 checked out
   8 and ran `git reset --hard fbbe4045871f`
   9
  10 Git reported that it updated 112465 files, and near to the beginning,
  11 filter-process died of signal 15.
  12
  13 Even better, it is reproducible, going back to that
  14 starting commit and running that command again works every time!
  15
  16 And I got a strace too. Here is the git command:
  17
  18         write(5, "0013command=smudge\n", 19)    = 19
  19         write(5, "0019pathname=new/cleanup\n", 25) = 25
  20         write(5, "0035treeish=fbbe4045871fb749299b"..., 53) = 53
  21         write(5, "0032blob=baad2545defeae59f526ea3"..., 50) = 50
  22         write(5, "0000", 4)                     = 4
  23         write(5, "0322", 4)                     = 4
  24         write(5, "#!/bin/sh\n\ngit commit -m 'pre cl"..., 798) = 798
  25         write(5, "0000", 4)                     = 4
  26         read(6, "0000", 4)                      = 4
  27         rt_sigaction(SIGPIPE, {sa_handler=0x563cf8debb50, sa_mask=[PIPE], sa_flags=SA_RES
  28         TORER|SA_RESTART, sa_restorer=0x7fab5717c920}, {sa_handler=SIG_IGN, sa_mask=[PIPE
  29         ], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fab5717c920}, 8) = 0
  30         write(2, "error: external filter 'git-anne"..., 57) = 57
  31         kill(1638045, SIGTERM)                  = 0
  32
  33 So git sends SIGTERM when it gets unhappy with the response it got from
  34 git-annex filter-process.
  35
  36 Here is where git runs git-annex filter-process via the shell:
  37
  38         execve("/bin/sh", ["/bin/sh", "-c", "git-annex filter-process", "git-annex filter-process"], 0x563cfacbfb40 /* 68 vars */) = 0
  39         ...
  40         newfstatat(AT_FDCWD, "/home/joey/bin/git-annex", {st_mode=S_IFREG|0755, st_size=72524080, ...}, 0) = 0
  41         rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], NULL, 8) = 0
  42         vfork()                                 = 1631132
  43         rt_sigprocmask(SIG_SETMASK, [], ~[KILL STOP RTMIN RT_1], 8) = 0
  44         wait4(-1, 0x7fff910d697c, 0, NULL)      = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
  45         --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=1631129, si_uid=1000} ---
  46         +++ killed by SIGTERM +++
  47
  48 But the actual git-annex process read the last thing git wrote to it,
  49 replied, and keeps running until it later reads an EOF from git.
  50
  51         write(1, "0000", 4)                     = 4
  52         poll([{fd=0, events=POLLIN}], 1, 0)     = 0 (Timeout)
  53         epoll_ctl(4, EPOLL_CTL_MOD, 0, {EPOLLIN|EPOLLONESHOT, {u32=0, u64=287065581021036544}}) = 0
  54         futex(0x67fe568, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
  55         futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0
  56         futex(0x67fe68c, FUTEX_WAKE_PRIVATE, 1) = 1
  57         read(0, "0013command=smudge\n0019pathname=new/cleanup\n0035treeish=fbbe4045871fb749299b4484862645bd9a7f175a\n0032blob=baad2545defeae59f526ea3d64174398899cb9cc\n00000322", 8192) = 155
  58         poll([{fd=0, events=POLLIN}], 1, 0)     = 1 ([{fd=0, revents=POLLIN}])
  59         futex(0x67fe688, FUTEX_WAKE_PRIVATE, 1) = 1
  60         futex(0x67fe690, FUTEX_WAKE_PRIVATE, 1) = 0
  61         read(0, "#!/bin/sh....", 8192) = 802
  62         futex(0x67fe56c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
  63         futex(0x67fe570, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
  64         futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0
  65         poll([{fd=1, events=POLLOUT}], 1, 0)    = 1 ([{fd=1, revents=POLLOUT}])
  66         futex(0x67fe68c, FUTEX_WAKE_PRIVATE, 1) = 1
  67         futex(0x67fe690, FUTEX_WAKE_PRIVATE, 1) = 0
  68         write(1, "0013status=success\n", 19)    = 19
  69         futex(0x67fe568, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
  70         futex(0x67fe570, FUTEX_WAKE_PRIVATE, 1) = 0
  71         poll([{fd=1, events=POLLOUT}], 1, 0)    = 1 ([{fd=1, revents=POLLOUT}])
  72         write(1, "0000", 4)                     = 4
  73         poll([{fd=1, events=POLLOUT}], 1, 0)    = 1 ([{fd=1, revents=POLLOUT}])
  74         write(1, "0322#!/bin/sh...", 802) = 802
  75         poll([{fd=1, events=POLLOUT}], 1, 0)    = 1 ([{fd=1, revents=POLLOUT}])
  76         write(1, "0000", 4)                     = 4
  77         poll([{fd=1, events=POLLOUT}], 1, 0)    = 1 ([{fd=1, revents=POLLOUT}])
  78         write(1, "0000", 4)                     = 4
  79         poll([{fd=0, events=POLLIN}], 1, 0)     = 0 (Timeout)
  80
  81 Git does not see that 0013status=success response though. It sees "0000",
  82 which must be the one that git-annex wrote earlier (top of above strace).
  83
  84 So, this seems like a protocol problem of some kind.
  85 """]